Projects: LOOPS : MW Model Logging through AspectJ
This page last changed on Dec 22, 2009 by aunger.

MW Model Logging through AspectJ

Overview

Recently it was requested to log student interactions with Molecular Workbench models. Things such as button clicks and model start/stop/reset clicks were of particular interest. After exploring various options (custom logging scripts, modifying MW to support easier logging, using a glass pane to trap mouse clicks, etc.), we decided to explore and use Aspect Oriented Programming (AOP) – AspectJ's implementation, specifically – to accomplish this without needing to modify MW or have model authors annotate or instrument their models.

AspectJ

AspectJ is the de-facto implementation of AOP. See their website for more info about the project.

What is being logged

MW supports a variety of ways for the user to interact with a Page or Model. Some of these ways are straightforward to log using aspects, and others not so much.

Buttons

Most of the button components in MW extend JButton, which means that they eventually call the actionPerformed() method on one or more ActionListeners. This makes them easy to instrument in AspectJ.

pointcut actionPerformed(): execution(* ActionListener.actionPerformed(ActionEvent));

This pointcut captures:

  • Model toolbar buttons
  • PageButtons
  • Model start/stop/reset/etc. controls
  • HTML buttons (buttons embedded in an HTML container using the <input> element)
  • Radio buttons
  • Checkboxes

Text Links

MW also supports clicking on links within text to trigger events. In java, hyperlinks actions are triggered via calling hyperlinkUpdate() on a HyperlinkListener. MW also extends this to have 2 different types of hyperlinks – ones with scripts (hyperlinks) and ones without (hotlinks). So additionally, MW has a hotlinkUpdate() method.

pointcut hyperlink(): execution(* hyperlinkUpdate(HyperlinkEvent)) || execution(* hotlinkUpdate(HyperlinkEvent));

Other Script Triggers

Eventually, many user interactions trigger a script. If the user action has not already been logged by one of the above pointcuts, they will then be caught and logged here.

pointcut runScript(): call(* runScript(String));

What's missing?

Model interactions

Aside from the start/stop/reset/etc. buttons at the bottom of a model, a user can interact with the model in many different ways – dragging atoms around, increasing or decreasing kinetic energy via the embedded temperature controls, and interacting with other embedded controls. Right now, these ways of interacting are not logged.

OTrunk side of things

So how does the Aspect actually store these user actions? AspectJ can insert new fields and methods into classes. Using this, we've inserted a new property on the OTModelerPage object: events.

public abstract OTObjectList OTModelerPage.getEvents();

This OTObjectList is meant to hold a sequence of OTActionItem. OTActionItem is basically a wrapper around OTResourceMap – you define a bunch of String keys with corresponding String values. Each of these OTActionItems gets attached to the model which was the source of the action.

Example

Here's a model:

The logs are currently pretty raw and will eventually be cleaned up to be easier to read/parse. However, it was decided that it would be better to err on the side of too much information, rather than too little.

The user's session data would contain:

<entry key="87639b0a-3a50-11de-87fd-db993fdba086">
                <OTModelerPage>
                  <events>
                    <OTActionItem>
                      <properties>
                        <entry key="script">
                          <string>stop;
define %molecule rand()*(%number_of_molecules-1);
define %atom1 0;
set %atom1 atomOfMolecule(%molecule,0);
define %atom2 0;
set %atom2 atomOfMolecule(%molecule,1);
while ((%atom[%atom1].id != 1) or (%atom[%atom1].ry &lt; 10) or (%atom[%atom1].rx &gt; 30));
print id: %atom[%atom1].id    x: %atom[%atom1].rx   y: %atom[%atom1].ry;
	set %molecule rand()*(%number_of_molecules-1);
	set %atom1 atomOfMolecule(%molecule,0);
endwhile;
set %atom2 atomOfMolecule(%molecule,1);
define %bond 0;
set %bond whichrbond(%atom1,%atom2);
define %sparkX 0;
set %sparkX (%atom[%atom1].rx+%atom[%atom2].rx)/2;
define %sparkY 0;
set %sparkY (%atom[%atom1].ry+%atom[%atom2].ry)/2;
add image spark.gif (%sparkX, "%sparkY-4.3"); //make point of spark appear at bond.
select image none;
select atom %atom1 or %atom2;
set visible off;
delay 0.25;
set visible on;
delay 0.25;
set visible off;
delay 0.25;
set visible on;
delay 0.25;
select image all;
remove;
select rbond %bond;
remove;
set atom[%atom1].vx -4000; // set the two radicals to fly off in opposite directions
set atom[%atom2].vx 4000;
run;</string>
                        </entry>
                        <entry key="name">
                          <string>Execute MW Script</string>
                        </entry>
                        <entry key="event">
                          <string>java.awt.event.ActionEvent[ACTION_PERFORMED,cmd=Spark,when=1261499705627,modifiers=Button1] on Execute MW script</string>
                        </entry>
                        <entry key="description">
                          <string>Execute MW script</string>
                        </entry>
                        <entry key="source">
                          <string>&lt;class&gt;org.concord.modeler.PageButton&lt;/class&gt;
&lt;title&gt;Spark&lt;/title&gt;
&lt;opaque&gt;false&lt;/opaque&gt;
&lt;modelclass&gt;org.concord.mw2d.models.ReactionModel&lt;/modelclass&gt;
&lt;model&gt;4&lt;/model&gt;
&lt;disabled_at_script&gt;true&lt;/disabled_at_script&gt;
&lt;script&gt;stop;
define %molecule rand()*(%number_of_molecules-1);
define %atom1 0;
set %atom1 atomOfMolecule(%molecule,0);
define %atom2 0;
set %atom2 atomOfMolecule(%molecule,1);
while ((%atom[%atom1].id != 1) or (%atom[%atom1].ry &amp;lt; 10) or (%atom[%atom1].rx &amp;gt; 30));
print id: %atom[%atom1].id    x: %atom[%atom1].rx   y: %atom[%atom1].ry;
	set %molecule rand()*(%number_of_molecules-1);
	set %atom1 atomOfMolecule(%molecule,0);
endwhile;
set %atom2 atomOfMolecule(%molecule,1);
define %bond 0;
set %bond whichrbond(%atom1,%atom2);
define %sparkX 0;
set %sparkX (%atom[%atom1].rx+%atom[%atom2].rx)/2;
define %sparkY 0;
set %sparkY (%atom[%atom1].ry+%atom[%atom2].ry)/2;
add image spark.gif (%sparkX, &amp;quot;%sparkY-4.3&amp;quot;); //make point of spark appear at bond.
select image none;
select atom %atom1 or %atom2;
set visible off;
delay 0.25;
set visible on;
delay 0.25;
set visible off;
delay 0.25;
set visible on;
delay 0.25;
select image all;
remove;
select rbond %bond;
remove;
set atom[%atom1].vx -4000; // set the two radicals to fly off in opposite directions
set atom[%atom2].vx 4000;
run;&lt;/script&gt;
&lt;action&gt;Execute MW script&lt;/action&gt;</string>
                        </entry>
                        <entry key="timestamp">
                          <string>1261499705628</string>
                        </entry>
                        <entry key="target">
                          <string>org.concord.mw2d.models.ScriptAction</string>
                        </entry>
                      </properties>
                    </OTActionItem>
                    <OTActionItem>
                      <properties>
                        <entry key="script">
                          <string>stop;</string>
                        </entry>
                        <entry key="name">
                          <string>Execute MW Script</string>
                        </entry>
                        <entry key="event">
                          <string>java.awt.event.ActionEvent[ACTION_PERFORMED,cmd=stop,when=1261499713498,modifiers=Button1] on Execute MW script</string>
                        </entry>
                        <entry key="description">
                          <string>Execute MW script</string>
                        </entry>
                        <entry key="source">
                          <string>&lt;class&gt;org.concord.modeler.PageButton&lt;/class&gt;
&lt;title&gt;stop&lt;/title&gt;
&lt;tooltip&gt;stop the model&lt;/tooltip&gt;
&lt;opaque&gt;false&lt;/opaque&gt;
&lt;modelclass&gt;org.concord.mw2d.models.ReactionModel&lt;/modelclass&gt;
&lt;model&gt;4&lt;/model&gt;
&lt;script&gt;stop;&lt;/script&gt;
&lt;action&gt;Execute MW script&lt;/action&gt;</string>
                        </entry>
                        <entry key="timestamp">
                          <string>1261499713499</string>
                        </entry>
                        <entry key="target">
                          <string>org.concord.mw2d.models.ScriptAction</string>
                        </entry>
                      </properties>
                    </OTActionItem>
                    <OTActionItem>
                      <properties>
                        <entry key="script">
                          <string>reset</string>
                        </entry>
                        <entry key="name">
                          <string>Execute MW Script</string>
                        </entry>
                        <entry key="event">
                          <string>java.awt.event.ActionEvent[ACTION_PERFORMED,cmd=Reset,when=1261499714643,modifiers=Button1] on Execute MW script</string>
                        </entry>
                        <entry key="description">
                          <string>Execute MW script</string>
                        </entry>
                        <entry key="source">
                          <string>&lt;class&gt;org.concord.modeler.PageButton&lt;/class&gt;
&lt;title&gt;Reset&lt;/title&gt;
&lt;tooltip&gt;Reset&lt;/tooltip&gt;
&lt;border&gt;Raised Bevel&lt;/border&gt;
&lt;opaque&gt;false&lt;/opaque&gt;
&lt;modelclass&gt;org.concord.mw2d.models.ReactionModel&lt;/modelclass&gt;
&lt;model&gt;4&lt;/model&gt;
&lt;disabled_at_script&gt;true&lt;/disabled_at_script&gt;
&lt;script&gt;reset&lt;/script&gt;
&lt;action&gt;Execute MW script&lt;/action&gt;</string>
                        </entry>
                        <entry key="timestamp">
                          <string>1261499714643</string>
                        </entry>
                        <entry key="target">
                          <string>org.concord.mw2d.models.ScriptAction</string>
                        </entry>
                      </properties>
                    </OTActionItem>
                  </events>
                </OTModelerPage>
              </entry>

In this snippet you can see 3 OTActionItems were logged – one for each interaction that occurred:

  1. Clicking the "Spark" button
  2. Clicking the "Stop" button
  3. Clicking the "Reset" button

Attachments:
Picture 24.png (image/png)
Comments:

Watch out for authored scripts that get periodically called from the task manager. This could quickly generate HUGE learner data files.
Posted by ddamelin at Dec 23, 2009 08:45

Currently the runScript() advice also does some further filtering which, at the moment, makes it ignore Task scripts. The tests should be updated to test for this, however, so we know we're ok in the future.
Posted by aunger at Dec 23, 2009 14:53
Document generated by Confluence on Jan 27, 2014 16:43